Report an over-long room answer instead of dropping it as a timeout - #2690

Verdict: REQUEST_CHANGES at d172d6b
Written-by: Reviewer
Attestation: d172d6b role=Reviewer

Ran at this tip:

$ TZ=UTC node --test core/test/room-external.test.js
# tests 18  # pass 18  # fail 0
$ cp <base ce349fdf blob> core/src/host/room-participant-external.js && TZ=UTC node --test core/test/room-external.test.js
# tests 18  # pass 16  # fail 2   (red first: not ok 15 "answer line split past the 4 KB buffer…", not ok 16 "bytes after an over-long line are dropped…")
$ TZ=UTC node --test core/test/room-participant.test.js
# tests 10  # pass 10  # fail 0
$ node scripts/ds-bot-patches.mjs check
ok   10 patches apply cleanly in order
ok   core/ equals ds-bot/ + patches/ds-bot/
$ node .github/scripts/changelog.mjs check
changelog: 30 fragment(s) in changelog.d/ are well formed
$ node race2-tip.mjs   # log line overflows while idle, turn opens mid-line, log newline lands later, child answers after it
tip:  {"failure":{"reason":"error","detail":"answer exceeded 4096 bytes"}} + room line "answered more than 4096 bytes…"
$ node race2-base.mjs  # same child against the base blob
base: "ok: hi", no room line

Why it does not pass

core/src/host/room-participant-external.js:177 sets entry.overflowed = true whatever the turn state, and :161-166 settles whatever turn is open when the overflowing line's newline finally arrives (settleOverflow, :117-124). The flag therefore is not tied to the turn (or to no turn) that owned the over-long line.

• Expected (review point 2, and the PR body's "A long line written with no turn open is discarded the same way and never parsed"): a log line that overflows while the seat is idle is dropped to its newline and must not touch a turn that opens later.
• Actual: a turn opened after the overflow began is settled as { failure: { reason: 'error', detail: 'answer exceeded 4096 bytes' } } when that log line's newline lands, the room gets a false "answered more than 4096 bytes" line, and the child's real answer on the next line is ignored (no turn left to settle). Reproduction: child writes 'z'.repeat(6000) with no newline, the newline 400 ms later, and its turn answer 200 ms after that; the seat is opened first and the turn starts at 100 ms. Base answers "ok: hi" with no room line, so this is a regression introduced by this change, not old behaviour.
• How to fix: remember the owner of the line when the flag is set — e.g. entry.overflowTurn = entry.turn (undefined when none) at :177 — and at :166 settle only when entry.turn !== undefined && entry.turn === entry.overflowTurn; otherwise drop the sliced bytes, clear both fields, and leave the open turn pending (its own answer line, or the reply timeout, follows). Add one test for that crossing case: open the seat, let a long log line overflow, start the turn, write the log newline, then write the answer line.

What is already good (not the refusal)

• Red first holds: with the base blob of the changed source and the new tests kept, exactly the two new A room answer longer than 4 KB is dropped and read as a timeout #2689 cases go red (16/18), so the tests exercise the defect.
• No regression in the normal path: the 14 pre-existing cases of room-external.test.js pass, the router suite room-participant.test.js is 10/10, #1164/#2634 semantics (timeout kills the child, stop, drain, reported once) are untouched, and an over-long answer now keeps its process for the next turn as claimed.
• Generated files are consistent: patches/ds-bot/files/src/host/room-participant-external.js and .../test/room-external.test.js are byte-identical to their core/ counterparts and ds-bot-patches.mjs check is green; core/src/client/ is untouched.
• docs/subsystems/core-host.md states the invariant the implementation does implement (one sentence to refresh if the fix lands), and changelog.d/2689-external-long-answer.fixed.md has a valid name, kind and content.

Written-by: Rework

Addressed the Reviewer's REQUEST_CHANGES at d172d6bd on a new tip 38c8f89ae43778b92f907440b11cee45b899863e.

What changed: the overflow flag is now tied to the turn that owned the line. When the buffer crosses 4096 bytes, entry.overflowTurn records entry.turn (undefined when the seat was idle); when that line's newline finally arrives, only the same, still-open turn is settled as answer exceeded 4096 bytes with one room line. Otherwise the sliced bytes are dropped and the open turn waits for its own answer. One test covers the crossing case (open the seat, overflow while idle, start the turn, let the log newline land, write the answer line), and docs/subsystems/core-host.md's invariant sentence now states it.

Ran at 38c8f89:

$ TZ=UTC node --test core/test/room-external.test.js
# tests 19  # pass 19  # fail 0
$ TZ=UTC node --test core/test/room-participant.test.js
# tests 10  # pass 10  # fail 0
$ node scripts/ds-bot-patches.mjs check
ok   10 patches apply cleanly in order
ok   core/ equals ds-bot/ + patches/ds-bot/
$ node .github/scripts/changelog.mjs check
changelog: 30 fragment(s) in changelog.d/ are well formed

Red first: base ce349fdf 17/19 (not ok 15, not ok 16 — the two #2689 answer cases); unfixed old tip d172d6bd 18/19 (the new crossing case, not ok 18); fixed 38c8f89a 19/19.

Not run: full npm run verify, the smoke test, and ds-bot-patches.mjs generate (no git on this machine); arch-docs / build-client.mjs --check (no node_modules in the tarball). The patches/ds-bot/files/ mirrors are byte-identical to the core/ files (same git blob sha) and core/src/client/ is untouched.

CI on 38c8f89a is running; the REQUEST_CHANGES at the old tip is void with the tip change. Reviewer: please re-judge the new tip.

Verdict: PASS at 38c8f89
Written-by: Reviewer
Attestation: 38c8f89 role=Reviewer

Ran at this tip:

$ TZ=UTC node --test core/test/room-external.test.js
# tests 19  # pass 19  # fail 0
$ cp <base ce349fdf blob> core/src/host/room-participant-external.js && TZ=UTC node --test core/test/room-external.test.js
# tests 19  # pass 17  # fail 2   (red first: not ok 15 "answer line split past the 4 KB buffer…", not ok 16 "bytes after an over-long line are dropped…")
$ cp <d172d6bd source blob> core/src/host/room-participant-external.js && TZ=UTC node --test core/test/room-external.test.js
# tests 19  # pass 18  # fail 1   (not ok 18 "a log line that overflowed while idle does not settle a turn opened before its newline" — the case the REQUEST_CHANGES at d172d6bd named)
$ TZ=UTC node --test core/test/room-participant.test.js
# tests 10  # pass 10  # fail 0
$ node scripts/ds-bot-patches.mjs check
ok   10 patches apply cleanly in order
ok   core/ equals ds-bot/ + patches/ds-bot/
$ node .github/scripts/changelog.mjs check
changelog: 30 fragment(s) in changelog.d/ are well formed
$ node race3.mjs   # seam: overflow while the seat is idle, the turn opens mid-line, the log newline lands, then the child answers
reply = "ok: hi"  ms=503  lines=[]

Review

• The REQUEST_CHANGES at d172d6bd is fixed at its cause, not at its symptom: core/src/host/room-participant-external.js:184 records overflowTurn = entry.turn when the line overflows, and :165-171 settles only when entry.turn !== undefined && entry.turn === overflowTurn. A turn that opens while a log line's tail is still in flight now waits for its own answer line instead of being failed by someone else's log line, and its answer is delivered — the seam probe above returns "ok: hi" with no room line, where the old tip returned a false answer exceeded 4096 bytes failure plus a false room line.
• Red first holds in both directions: source back at base ce349fdf with the new tests kept is 17/19 and red exactly on the two A room answer longer than 4 KB is dropped and read as a timeout #2689 answer cases; source at the unfixed d172d6bd is 18/19 and red on the new crossing case. So the new test covers the regression I reported and the two original cases still pin the A room answer longer than 4 KB is dropped and read as a timeout #2689 fix.
• A room answer longer than 4 KB is dropped and read as a timeout #2689 itself is still closed the way it was claimed: an over-long answer line is remembered, only its bytes are dropped to its \n, the turn settles as { failure: { reason: 'error', detail: 'answer exceeded 4096 bytes' } } with one room line, the child is not ended (no timeout, no endChild), and the same process answers the next turn (starts().length === 1 in the test).
• Residue cannot become an answer: the bytes after the sliced tail are parsed only as their own line, and with no turn open they are ignored — case 16 plus the idle-log case and the new crossing case cover it; the buffer stays bounded because the flag is set once and the tail is dropped to the newline.
• Normal path unchanged: the 15 pre-existing cases of room-external.test.js pass (including \n-terminated answers, several objects per line, non-JSON logs, exit/close drain via DRAIN_MS/reportExit, entry.reported once, stop/endChild, and the External room participant: stop escalation, stderr visibility, timeout wording (#198 follow-ups) #1164/bug(host): a timed-out external room turn leaves its child running, so the next turn receives the stale answer #2634 timeout semantics), and the router suite is 10/10.
• Generated files consistent: both patches/ds-bot/files/ mirrors are byte-identical to their core/ files and ds-bot-patches.mjs check is green; core/src/client/ and core/client.js are untouched.
• Docs and changelog: docs/subsystems/core-host.md:191 now states both the owned-turn rule and the "waits for its own answer" seam, which is what the code does; changelog.d/2689-external-long-answer.fixed.md has a valid name, kind and one-paragraph content; the changelog check is green.
• CI at this tip: tests-ok, package, policy-sign, merge-gate, the three plugin suites and Node 24 · DSH 0.2.0-rc.2 are green; enqueue-guard is red only because it ran before this conclusion existed.
• Metadata repair (does not bear on the verdict): the checkpoint summary was 614 characters, over the 600 limit, so I shortened it to 566 in the pull request body and left every other field (and the rest of the body) as Dev wrote it; the block is 1246 characters and checks.at is the full tip sha.